非同期Lambda用の新しいCloudWatchメトリクスが３つ追加されました（AsyncEventsReceived, AsyncEventAge, AsyncEventsDropped）

非同期実行するLambdaについて、新しいCloudWatchメトリクスが追加されました。

• AsyncEventsReceived
  • イベントが正常にキューに入った数
• AsyncEventAge
  • イベントがキューに入ったあと、Lambdaを呼び出すまでの時間
• AsyncEventsDropped
  • Lambdaが正常実行されず、Dropされたイベントの数

というわけで、さっそく試してみました。

おすすめの方

• 非同期実行するLambdaに追加された3つのメトリクスを知りたい方

事前準備

次のAWSブログ、もしくはGitHubリポジトリの内容に従って進めます。

• Introducing new asynchronous invocation metrics for AWS Lambda | AWS Compute Blog
• aws-samples/lambda-async-metrics-sample

1. AWSリージョンを設定する

export REGION=ap-northeast-1

2. GitHubリポジトリをCloneする

git clone https://github.com/aws-samples/lambda-async-metrics-sample.git
cd lambda-async-metrics-sample

SAMテンプレートを確認すると、タイムアウトが100秒のLambdaがひとつ定義されています。 Lambdaの起動トリガーは未設定です。

3. アプリケーションをビルドしてデプロイする

スタック名のオプションを追加して、コマンドを実行します。他のオプションはデフォルトで進めます。

sam build
sam deploy --guided --region $REGION --stack-name lambda-async-metrics

4. 環境変数に「デプロイしたLambdaの関数名」を保存する

FUNCTION_NAME=$(aws cloudformation describe-stacks \
  --region $REGION \
  --stack-name lambda-async-metrics \
  --query 'Stacks[0].Outputs[?OutputKey==`HelloWorldFunctionResourceName`].OutputValue' --output text)

5. AWS CLIでLambda関数を実行する

生成されたout_file.txtの中身はemptyでした

aws lambda invoke \
  --region $REGION \
  --function-name $FUNCTION_NAME \
  --invocation-type Event out_file.txt

6. CloudWatchメトリクスを確認する

Lambda関数名の一部である「lambda-async-metrics」を入力して検索します。 8個のメトリクスが表示されました。新しく追加されたメトリクスもあります。

• AsyncEventsDropped
• AsyncEventAge
• AsyncEventsReceived

ちなみに、このときのメトリクスは次の内容でした。

シナリオ1： 例外発生させて、非同期実行するLambdaをリトライさせてみる

Lambdaコードを変更して、例外発生させる

3行目を追加します。

def lambda_handler(event, context):
    print("Hello World from AWS Lambda")
    raise Exception("Lambda function throwing exception")

ビルド＆デプロイ

sam build && sam deploy –region $REGION

Lambda関数を実行する

aws lambda invoke \
  --region $REGION \
  --function-name $FUNCTION_NAME \
  --invocation-type Event out_file.txt

CloudWatchメトリクスを確認する

しばらく待つと、メトリクスが登場しました。

18:30時点では、Lambdaが2回動作し、2回エラーになったことが分かります。 AsyncEventAgeは、リトライ時の呼び出し待ち時間でも増加するため、1回目の失敗から2回目の呼び出しまでが約56秒だと分かります。 Lambdaのログでもそのぐらいの時間となっています。

18:35時点では、Lambdaが1回動作し、1回エラーになったことが分かります。 この時点で2回の再試行（計3回の実行）が終わったため、AsyncEventsDroppedが1になっています。 AsyncEventAgeが約162秒になっていることから、この値は、「1回目のLambda実行からの経過時間」のようですね。

シナリオ2： Lambdaをスロットリングさせてみる

SAMテンプレートを更新して、予約済み同時実行数を1にする

Lambdaの予約済み同時実行数を1にします。 タイムアウト時間は、Cloneした時点で100でした。

AWSTemplateFormatVersion: '2010-09-09'
Transform: AWS::Serverless-2016-10-31
Description: lambda-async-metrics-sample

Resources:
  HelloWorldFunction:
    Type: AWS::Serverless::Function
    Properties:
      CodeUri: hello_world/
      Handler: app.lambda_handler
      Runtime: python3.9
      Timeout: 100
      MemorySize: 128
      Architectures:
      - x86_64
      ReservedConcurrentExecutions: 1

  HelloWorldFunctionLogGroup:
    Type: AWS::Logs::LogGroup
    Properties:
      LogGroupName: !Sub "/aws/lambda/${HelloWorldFunction}"
      RetentionInDays: 7

Outputs:
  HelloWorldFunctionResourceName:
    Description: Hello World Lambda Function name
    Value: !Ref HelloWorldFunction

Lambdaコードを変更して、90秒のSleepをする

import time

def lambda_handler(event, context):
    time.sleep(90)
    print("Hello from AWS Lambda")

ビルド＆デプロイ

sam build && sam deploy –region $REGION

Lambda関数を連続で2回実行する

aws lambda invoke \
  --region $REGION \
  --function-name $FUNCTION_NAME \
  --invocation-type Event out_file.txt


aws lambda invoke \
  --region $REGION \
  --function-name $FUNCTION_NAME \
  --invocation-type Event out_file.txt

CloudWatchメトリクスを確認する

しばらく待つと、メトリクスが登場しました。

19:20時点のAsyncEventsReceivedを見ると、2つのイベントがキューに入ったことが分かります。 そして、1つのLambda呼び出しと1つのスロットリングが発生しています。

19:21時点と19:22時点では、スロットリングが増加しています。

19:23時点で、Lambdaの呼び出しがありました。

ログを見ると、Lambdaが2回実行されたことが分かります。

シナリオ3： Lambdaが受け取るイベントの有効期限を60秒にしてみる

SAMテンプレートを更新して、Lambdaが受け取るイベントの有効期限を60秒にする

予約済み同時実行数は1のままです。

AWSTemplateFormatVersion: '2010-09-09'
Transform: AWS::Serverless-2016-10-31
Description: lambda-async-metrics-sample

Resources:
  HelloWorldFunction:
    Type: AWS::Serverless::Function
    Properties:
      CodeUri: hello_world/
      Handler: app.lambda_handler
      Runtime: python3.9
      Timeout: 100
      MemorySize: 128
      Architectures:
      - x86_64
      ReservedConcurrentExecutions: 1
      EventInvokeConfig:
        MaximumEventAgeInSeconds: 60

  HelloWorldFunctionLogGroup:
    Type: AWS::Logs::LogGroup
    Properties:
      LogGroupName: !Sub "/aws/lambda/${HelloWorldFunction}"
      RetentionInDays: 7

Outputs:
  HelloWorldFunctionResourceName:
    Description: Hello World Lambda Function name
    Value: !Ref HelloWorldFunction

ビルド＆デプロイ

sam build && sam deploy –region $REGION

Lambda関数を連続で2回実行する

aws lambda invoke \
  --region $REGION \
  --function-name $FUNCTION_NAME \
  --invocation-type Event out_file.txt


aws lambda invoke \
  --region $REGION \
  --function-name $FUNCTION_NAME \
  --invocation-type Event out_file.txt

CloudWatchメトリクスを確認する

しばらく待つと、メトリクスが登場しました。

2つのイベントを受け取り、1つを実行し、スロットリングが発生して1つが破棄されました。

さいごに

実際のプロジェクトでの適用箇所を検討してみたいと思います。

参考

• AWS Lambda launches new CloudWatch metrics for asynchronous invocations
• Introducing new asynchronous invocation metrics for AWS Lambda | AWS Compute Blog
• aws-samples/lambda-async-metrics-sample
• Working with Lambda function metrics - AWS Lambda